/** \file log.c
 * \verbatim
 * General C/C++ logging/debug functions and macros
 * 
 * Copyright (c) 2001-2003 Wouter Caarls, Delft University of Technology
 * 
 * This library is free software; you can redistribute it and/or
 * modify it under the terms of the GNU Lesser General Public
 * License as published by the Free Software Foundation; either
 * version 2.1 of the License, or (at your option) any later version.
 *
 * This library is distributed in the hope that it will be useful,
 * but WITHOUT ANY WARRANTY; without even the implied warranty of
 * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the GNU
 * Lesser General Public License for more details.
 *
 * You should have received a copy of the GNU Lesser General Public
 * License along with this library; if not, write to the Free Software
 * Foundation, Inc., 59 Temple Place, Suite 330, Boston, MA  02111-1307  USA
 * \endverbatim      
 */
 
#include <stdio.h> 
#include <stdarg.h>
#include <stdlib.h>
#include <strings.h>
#include <unistd.h>
#include <errno.h>
#include <string.h>
#include <time.h>
#include <sys/time.h>
#include <sched.h>

#include "log.h"

/*
 * Globals
 */

static pthread_mutex_t log_mutex;                ///< Logging mutex.
static log_thread_t log_thread[LOG_MAX_THREADS]; ///< Thread names.
static int log_groups;                           ///< Number of log groups.
static log_group_t *log_group;                   ///< Log groups.
static int log_streams;                          ///< Number of log streams.
static log_stream_t *log_stream;                 ///< Log streams.
static int log_initialised = 0;                  ///< Whether the library has been initialised.

/*
 * Local prototypes
 */

/// Try to lock the logging system mutex.
inline static int logAcquireLock(void);

/*
 * Function definitions
 */

/// Initialise the logging system. Do not call.
__attribute__((constructor)) void liblog_init(void)
{
  if (!log_initialised)
  {
    pthread_mutex_init(&log_mutex, NULL);

    log_group = NULL;
    log_stream = NULL;
    log_groups = log_streams = 0;
    log_initialised = 1; 

    /* Create an internal logging stream for error logging */
    if (logAddNamedGroup("_internal") < 0 ||
        logAddStream("%d \x1B[31m\x1B[1mERR\x1B[0m %s(%l) [%t|%f] (%e): ", "stderr") < 0)
    {
      fprintf(stderr, "CRITICAL ERROR: Couldn't initialise logging system\n");
      exit(-1);
    }
    
    logAddNamedGroup("default");
    logAddDefaultStreams(NULL);
  }
}

/**
 * \see logAddNamedGroup
 */
int logAddGroup(void)
{
  return logAddNamedGroup(NULL);
}

/*
 * \param name Name of the new group. NULL for no name.
 * \returns new logging group identifier (-1 in case of failure).
 */
int logAddNamedGroup(const char *name)
{
  log_group_t *group;
  int retval;

  if (!log_initialised) return -1;

  if (logAcquireLock())
  {
    fprintf(stderr, "ERROR: Couldn't acquire logging system lock\n");
    return -1;
  }

  retval = log_groups++;
  abortOnNULL(STREAM(0), log_group =
              (log_group_t*) realloc(log_group, log_groups*sizeof(log_group_t)))
  group = &log_group[log_groups-1];

  if (name) 
  {
    abortOnNULL(STREAM(0), group->name =
                (char*) malloc((strlen(name)+1)*sizeof(char)));
    strcpy(group->name, name);
  }
  else
  {
    group->name = NULL;
  }
  
  pthread_mutex_unlock(&log_mutex);
  return retval;
}

/*
 * \param name Name of the group to find.
 * \returns logging stream identifier for the first stream in this group
 * (-1 if not found).
 */
int logGetFirstGroupStream(const char *name)
{
  int i, s;

  if (!log_initialised) return -1;

  if (logAcquireLock())
  {
    fprintf(stderr, "ERROR: Couldn't acquire logging system lock\n");
    return -1;
  }

  for (i=0; i < log_groups; i++)
  {
    if ((!name && !log_group[i].name) ||
        (name && log_group[i].name && !strcmp(log_group[i].name, name)))
    {
      for (s=0; s < log_streams; s++)
      {
        if (log_stream[s].group == i)
        {
          pthread_mutex_unlock(&log_mutex);
          return s;
        }
      }
    }
  }
  
  pthread_mutex_unlock(&log_mutex);
  return -1;
}

/*
 * \param stream previous stream identifier.
 * \returns next logging stream identifier (-1 if not found).
 */
int logGetNextGroupStream(int stream)
{
  int i;
  
  if (!log_initialised) return -1;

  if (logAcquireLock())
  {
    fprintf(stderr, "ERROR: Couldn't acquire logging system lock\n");
    return -1;
  }

  for (i=stream+1; i < log_streams; i++)
  {
    if (log_stream[i].group == log_stream[stream].group)
    { 
      pthread_mutex_unlock(&log_mutex);
      return i;
    }
  }
  
  pthread_mutex_unlock(&log_mutex);
  return -1;
}

/**
 * \param header format of the header of the stream.
 * The following substitutions are made:
 * \li \c %d Time of logging.
 * \li \c %f Function name.
 * \li \c %l Source code line.
 * \li \c %s Source code file.
 * \li \c %t Thread name.
 * \li \c %e Error string.
 * \param file file descriptor / file name / host name to log to.
 * \li \c "stdout" log to standard output
 * \li \c "stderr" log to standard error
 * \li \c "host:port" log by UDP to a remote socket.
 * \li \c "file" log to file \c file.
 * \returns new logging stream identifier (-1 in case of failure).
 * \par Example:
 * \code
 * logAddGroup();
 * logAddStream("%d ERR [%f|%t] %s(%l) %e: ", "stderr");
 * logAddStream("%d WRN [%f|%t]: ", "stderr");
 * logAddStream("%d NTC [%f|%t]: ", "stdout");
 * \endcode
 */
int
logAddStream(const char* header,
             const char* file)
{
  int i, port, retval;
  char host[256];
  struct sockaddr_in addr;
  struct hostent* ent;
  log_stream_t *stream;

  if (!log_initialised) return -1;

  if (logAcquireLock())
  {
    fprintf(stderr, "ERROR: Couldn't acquire logging system lock\n");
    return -1;
  }

  retval = log_streams++;
  if (!(log_stream = (log_stream_t*) realloc(log_stream, log_streams*sizeof(log_stream_t))))
  {
    log_streams--;
    pthread_mutex_unlock(&log_mutex);
    return -1;
  }

  /* Fill in the standard fields */
  stream = &log_stream[log_streams-1];
  stream->enabled = 1;
  stream->group = log_groups-1;
  stream->flush = 1;
  
  abortOnNULL(STREAM(0), stream->header =
              (char*) malloc((strlen(header)+1)*sizeof(char)));
  strcpy(stream->header, header);
  abortOnNULL(STREAM(0), stream->file =
              (char*) malloc((strlen(file)+1)*sizeof(char)));
  strcpy(stream->file, file);

  /* First see if there isn't another stream writing to
     the same file */
  for (i=0; i < log_streams-1; i++)
  {
    if (!strcmp(log_stream[i].file, file))
    {
      memcpy(&stream->type, &log_stream[i].type, sizeof(stream->type));
      memcpy(&stream->fd, &log_stream[i].fd, sizeof(stream->fd));
      memcpy(&stream->socket, &log_stream[i].socket, sizeof(stream->socket));
      memcpy(&stream->address, &log_stream[i].address, sizeof(stream->address));
      
      pthread_mutex_unlock(&log_mutex);
      return retval;
    }
  }

  /* See what type of logging we need to do */
  if (!strcmp(file, "stdout"))
  {
    /* Standard output */
    stream->type = LOG_STREAM_FD;
    stream->fd = stdout;
  }
  else if (!strcmp(file, "stderr"))
  {
    /* Standard error */
    stream->type = LOG_STREAM_FD;
    stream->fd = stderr;
  }
  else if (strchr(file, ':'))
  {
    /* Socket */
    stream->type = LOG_STREAM_SOCKET;

    /* Separate host from port */
    strcpy(host, file);
    *strchr(host, ':') = '\0';
    port = atoi(&strchr(file, ':')[1]);
    
    /* Bind to a local socket */
    bzero((char*)&addr, sizeof(addr));
    addr.sin_family = AF_INET;
    addr.sin_port = 0;
    addr.sin_addr.s_addr = INADDR_ANY;
      
    stream->socket = socket(AF_INET, SOCK_DGRAM, IPPROTO_UDP);
    if (bind(stream->socket, (struct sockaddr*) &addr, sizeof(addr)) < 0)
    {
      log_streams--;
      pthread_mutex_unlock(&log_mutex);
      returnErrorl((STREAM(0),
                   "Unable to bind socket for stream %d", retval));
    }
      
    /* Resolve the host name */
    bzero((char*)&stream->address, sizeof(stream->address));
    stream->address.sin_family = AF_INET;
    stream->address.sin_port = htons(port);
    
    ent = gethostbyname(host);
    if (!ent)
    {
      close(stream->socket);
      log_streams--;
      pthread_mutex_unlock(&log_mutex);
      returnErrorl((STREAM(0), "Unable to resolve hostname '%s' for stream %d",
                    host, retval));
    }

    memcpy(&stream->address.sin_addr.s_addr, *ent->h_addr_list,
           sizeof(stream->address.sin_addr.s_addr));
  }
  else
  {
    stream->type = LOG_STREAM_FILE;
    stream->fd = fopen(file, "a");
    if (!stream->fd)
    {
      log_streams--;
      pthread_mutex_unlock(&log_mutex);
      returnErrorl((STREAM(0), "Unable to open file '%s' for stream %d",
                  file, retval));
    }
  }
  
  pthread_mutex_unlock(&log_mutex);

  return retval;
}

/**
 * \param file file to point streams to. NULL for stdout/stderr logging.
 * \returns a structure containing the default stream pointers.
 * \par Example:
 * \code
 * logAddGroup();
 * logAddDefaultStreams(NULL);
 * \endcode
 */
log_default_streams_t
logAddDefaultStreams(const char *file)
{
  log_default_streams_t log_default_streams;
  
  if (file)
  {
    log_default_streams.crit = logAddStream(
      "%d \x1B[35m\x1B[1mCRT\x1B[0m %s(%l) [%t|%f]: ", file);
    log_default_streams.err = logAddStream(
      "%d \x1B[31m\x1B[1mERR\x1B[0m %s(%l) [%t|%f]: ", file);
    log_default_streams.warning = logAddStream(
      "%d \x1B[33m\x1B[1mWRN\x1B[0m %s(%l) [%t|%f]: ", file);
    log_default_streams.notice = logAddStream(
      "%d \x1B[34m\x1B[1mNTC\x1B[0m [%t|%f]: ", file);
    log_default_streams.info = logAddStream(
      "%d \x1B[32m\x1B[1mINF\x1B[0m [%t|%f]: ", file);
    log_default_streams.debug = logAddStream(
      "%d \x1B[0m\x1B[1mDBG\x1B[0m [%t|%f]: ", file);
    log_default_streams.crawl = logAddStream(
      "%d \x1B[0m\x1B[0mCRL\x1B[0m [%t|%f]: ", file);  
  }
  else
  {
    log_default_streams.crit = logAddStream(
      "%d \x1B[35m\x1B[1mCRT\x1B[0m %s(%l) (%e) [%t|%f]: ", "stderr");
    log_default_streams.err = logAddStream(
      "%d \x1B[31m\x1B[1mERR\x1B[0m %s(%l) (%e) [%t|%f]: ", "stderr");
    log_default_streams.warning = logAddStream(
      "%d \x1B[33m\x1B[1mWRN\x1B[0m %s(%l) [%t|%f]: ", "stderr");
    log_default_streams.notice = logAddStream(
      "%d \x1B[34m\x1B[1mNTC\x1B[0m [%t|%f]: ", "stdout");
    log_default_streams.info = logAddStream(
      "%d \x1B[32m\x1B[1mINF\x1B[0m [%t|%f]: ", "stdout");
    log_default_streams.debug = logAddStream(
      "%d \x1B[0m\x1B[1mDBG\x1B[0m [%t|%f]: ", "stdout");
    log_default_streams.crawl = logAddStream(
      "%d \x1B[0m\x1B[0mCRL\x1B[0m [%t|%f]: ", "stdout");  
  }

  logEdit(log_default_streams.warning, LOG_GROUP_SET_LEVEL);

  return log_default_streams;
}

/**
 *  \returns structure containting the program-default logging streams.
 */
log_default_streams_t
logGetDefaultStreams(void)
{
  int s;
  log_default_streams_t log_default_streams;
  
  s = logGetFirstGroupStream("default");

  log_default_streams.crit = s;
  log_default_streams.err = s = logGetNextGroupStream(s);
  log_default_streams.warning = s = logGetNextGroupStream(s);
  log_default_streams.notice = s = logGetNextGroupStream(s);
  log_default_streams.info = s = logGetNextGroupStream(s);
  log_default_streams.debug = s = logGetNextGroupStream(s);
  log_default_streams.crawl = s = logGetNextGroupStream(s);

  return log_default_streams;
}

/**
 * \param stream stream edit, or to take group from.
 * \param operation operation to perform on the stream or group.
 * \li \c LOG_STREAM_ENABLE to enable the stream.
 * \li \c LOG_STREAM_DISABLE to disable the stream.
 * \li \c LOG_STREAM_SET_FLUSH to set the stream to auto-flush.
 * \li \c LOG_STREAM_SET_NOFLUSH to set the stream to no flush.
 * \li \c LOG_GROUP_ENABLE Enables all the streams in the stream's group.
 * \li \c LOG_GROUP_DISABLE Disables all the streams in the stream's group.
 * \li \c LOG_GROUP_SET_LEVEL All the logging streams that were defined in the
 * stream's group before and including \c stream are enabled.
 * \li \c LOG_GROUP_SET_FLUSH Sets all the streams in the stream's group to
 * auto-flush.
 * \li \c LOG_GROUP_SET_NOFLUSH Sets all the streams in the stream's group to
 * no flush.
 * \li \c LOG_STREAM_GET_ENABLED to get the stream's enabled status
 * \li \c LOG_STREAM_GET_FLUSH to get the stream's auto-flush status.
 * \returns Result of operation (-1 on error)
 */
int
logEdit(int stream,
        int operation)
{
  int i;

  if (!log_initialised) return -1;

  if (stream < 0 || stream >= log_streams)
  {  
    lprintf(STREAM(0), "Invalid stream %d", stream);
    return -1;
  }

  if (logAcquireLock())
  {
    fprintf(stderr, "ERROR: Couldn't acquire logging system lock\n");
    return -1;
  }

  switch (operation)
  {
    case LOG_STREAM_ENABLE:
      log_stream[stream].enabled = 1;
      break;
    case LOG_STREAM_DISABLE:
      log_stream[stream].enabled = 0;
      break;
    case LOG_STREAM_SET_FLUSH:
      log_stream[stream].flush = 1;
      break;
    case LOG_STREAM_SET_NOFLUSH:
      log_stream[stream].flush = 0;
      break;
    case LOG_GROUP_ENABLE:
      for (i=0; i < log_streams; i++)
        if (log_stream[i].group == log_stream[stream].group)
          log_stream[i].enabled = 1;
      break;
    case LOG_GROUP_DISABLE:
      for (i=0; i < log_streams; i++)
        if (log_stream[i].group == log_stream[stream].group)
          log_stream[i].enabled = 0;
      break;
    case LOG_GROUP_SET_LEVEL:
      /* Find streams in the given group, and enable those below the given
         stream while disabling those below it */
      for (i=0; i < log_streams; i++)
        if (log_stream[i].group == log_stream[stream].group)
        {
          if (i <= stream)
            log_stream[i].enabled = 1;
          else
            log_stream[i].enabled = 0;
        }
      break;
    case LOG_GROUP_SET_FLUSH:
      for (i=0; i < log_streams; i++)
        if (log_stream[i].group == log_stream[stream].group)
          log_stream[i].flush = 1;
      break;
    case LOG_GROUP_SET_NOFLUSH:
      for (i=0; i < log_streams; i++)
        if (log_stream[i].group == log_stream[stream].group)
          log_stream[i].flush = 0;
      break;
    case LOG_STREAM_GET_ENABLED:
      pthread_mutex_unlock(&log_mutex);
      return log_stream[stream].enabled;
      break;
    case LOG_STREAM_GET_FLUSH:
      pthread_mutex_unlock(&log_mutex);
      return log_stream[stream].flush;
      break;
   default:
      pthread_mutex_unlock(&log_mutex);
      lprintf(STREAM(0), "Invalid operation: %d", operation);
      return -1;
  }    
       
  pthread_mutex_unlock(&log_mutex);
        return 0;
}

/**
 * \param file source file.
 * \param line source line.
 * \param function source function.
 * \param s stream to log to.
 * \param buf buffer to write header to.
 */
void
logPrintHeader(const char* file,
               int line,
               const char* function,
               int s,
               char *buf)
{
  log_stream_t *stream=&log_stream[s];
  int thread, l;
  unsigned int i, c=0;
  struct timeval tv;
  struct tm *tm;
  char tbuf[32];

  l = strlen(stream->header);
  for (i=0; i < l; i++)
  {
    if (stream->header[i] == '%' && i < l-1)
    {
      switch (stream->header[i+1])
      {
        case 'd':
          if (!gettimeofday(&tv, NULL))
          {
            tm = localtime(&tv.tv_sec);
            strftime(tbuf, 31, "%T", tm);
            sprintf(&buf[c], "%s.%.3d", tbuf, (int)(tv.tv_usec/1000));
            c = strlen(buf);
          }
          break;
        case 'f':
          if (function)
          {
            sprintf(&buf[c], "%s", function);
            c = strlen(buf);
          }
          break;
        case 'l':
          sprintf(&buf[c], "%d", line);
          c = strlen(buf);
          break;
        case 's':
          if (file)
          {
            sprintf(&buf[c], "%s", file);
            c = strlen(buf);
          }
          break;
        case 't':
          thread = pthread_self()%LOG_MAX_THREADS;
          while (log_thread[thread].used &&
                 log_thread[thread].id != pthread_self())
            thread = (thread+1)%LOG_MAX_THREADS;
          if (log_thread[thread].used)
          {
            sprintf(&buf[c], "%s", log_thread[thread].name);
            c = strlen(buf);
          }
          break;
        case 'e':
          sprintf(&buf[c], "%s", strerror(errno));
          c = strlen(buf);
          break;
        case '%':
          buf[c++] = '%';
          break;
      }
      i++;
    }
    else
      buf[c++] = stream->header[i];
  }

  buf[c] = '\0';
}

/**
 * \param s stream to log to.
 * \param buf buffer to log.
 */
void
logOut(int s,
       char *buf)
{
  log_stream_t *stream=&log_stream[s];

  if (!stream->enabled) return;

  if (logAcquireLock())
  {
    buf[strlen(buf)-1] = '}';
    fputc('{', stderr);
    fputs(buf, stderr);
    fputc('}', stderr);
    return;
  }

  switch (stream->type)
  {
    case LOG_STREAM_FD:
    case LOG_STREAM_FILE:
      fputs(buf, stream->fd);
      if (stream->flush)
        fflush(stream->fd);
      break;
    case LOG_STREAM_SOCKET:
      sendto(stream->socket, buf, strlen(buf)+1, 0,
             (struct sockaddr*) &stream->address, sizeof(stream->address));
      break;
  }

  pthread_mutex_unlock(&log_mutex);
}

/** 
 * \param file source file.
 * \param line source line.
 * \param function source function.
 * \param stream logging stream.
 * \param msg format.
 * \param ... variables to include in format string.
 * \note
 * Users will call this function with an encapsulation macro that
 * fills in the first four arguments.
 * \par Example:
 * \code
 * lprintf(STREAM(log.notice), "Starting threads");
 * \endcode
 */
void
lprintf(const char* file,
        int line,
        const char* function,
        int stream,
        const char* msg, ...)
{
  va_list ap;
  char buf[2048];

  if (!log_initialised) return;

  if (stream < 0 || stream >= log_streams)
  { 
    fprintf(stderr, msg);
    lprintf(STREAM(0), "Invalid stream %d", stream);
    return;
  }
    
  if (log_stream[stream].enabled)
  {
    logPrintHeader(file, line, function, stream, buf);
    va_start(ap, msg);
    (void) vsprintf(&buf[strlen(buf)], msg, ap);
    (void) sprintf(&buf[strlen(buf)], "\n");
    va_end(ap);

    logOut(stream, buf);
  }
}

/// Destroy the logging system. Do not call.
__attribute__((destructor)) void liblog_fini(void)
{
  int i;
  if (log_initialised)
  {   
    if (logAcquireLock())
    {
      fprintf(stderr, "WARNING: Couldn't destroy logging system\n");
      return;
    }
    
    for (i=0; i < log_streams; i++)
    {
      switch (log_stream[i].type)
      {
        case LOG_STREAM_FILE:
          fclose(log_stream[i].fd);
          break;
        case LOG_STREAM_SOCKET:
          close(log_stream[i].socket);
          break;
      }

      free(log_stream[i].header);
      free(log_stream[i].file);
    }

    for (i=0; i < LOG_MAX_THREADS; i++)
      if (log_thread[i].used)
        free(log_thread[i].name);

    log_initialised = 0;

    pthread_mutex_destroy(&log_mutex);
  }
}

/**
 * \param name name of the thread to be displayed in logging messages.
 */
void logRegisterThread(const char *name)
{
  int thread;
  
  if (!log_initialised) return;

  if (logAcquireLock())
  {
    fprintf(stderr, "ERROR: Couldn't acquire logging system lock\n");
    return;
  }

  /* Look for our place in the hash table */
  thread = pthread_self()%LOG_MAX_THREADS;
  while (log_thread[thread].used &&
         log_thread[thread].id != pthread_self())
    thread = (thread+1)%LOG_MAX_THREADS;
  if (log_thread[thread].used)
  {
    /* Thread already has an entry. Overwrite */
    log_thread[thread].used = 0;
    free(log_thread[thread].name);
  }
  else
  {
    /* Find an empty place */
    thread = pthread_self()%LOG_MAX_THREADS;
    while (log_thread[thread].used)
      thread = (thread+1)%LOG_MAX_THREADS;
  }

  log_thread[thread].id = pthread_self();
  abortOnNULL(STREAM(0), log_thread[thread].name =
              (char*) malloc((strlen(name)+1)*sizeof(char)));
  strcpy(log_thread[thread].name, name);
  log_thread[thread].used = 1;

  pthread_mutex_unlock(&log_mutex);
}

void logUnRegisterThread(void)
{
  int thread;
  
  if (!log_initialised) return;

  if (logAcquireLock())
  {
    fprintf(stderr, "ERROR: Couldn't acquire logging system lock\n");
    return;
  }

  /* Look for our place in the hash table */
  thread = pthread_self()%LOG_MAX_THREADS;
  while (log_thread[thread].used &&
         log_thread[thread].id != pthread_self())
    thread = (thread+1)%LOG_MAX_THREADS;
  if (log_thread[thread].used)
  {
    log_thread[thread].used = 0;
    log_thread[thread].id = 0;
    free(log_thread[thread].name);
  }

  pthread_mutex_unlock(&log_mutex);
}

/**
 * \retval 0 success
 * \retval -1 failure
 */
inline static int
logAcquireLock(void)
{
  struct timeval tv;
  long long timeout;

  /* Fast path */
  if (!pthread_mutex_trylock(&log_mutex)) return 0;

  /* Try for a while */
  gettimeofday(&tv, NULL);
  timeout = tv.tv_sec * 1000000L + tv.tv_usec + LOG_MAX_LOCK_TIME;

  do
  {
    gettimeofday(&tv, NULL);
    if (tv.tv_sec * 1000000L + tv.tv_usec > timeout) return -1;

    sched_yield();
  } while (pthread_mutex_trylock(&log_mutex));

  return 0;
}
